Skip to content

Log each Sidekiq line once, with the job's ID, and write logged Hashes at the top level - #17

Merged
ndbroadbent merged 5 commits into
mainfrom
nathan/sidekiq-fixes
Oct 17, 2026
Merged

ndbroadbent merged 5 commits into
mainfrom
nathan/sidekiq-fixes

Conversation

@ndbroadbent

@ndbroadbent ndbroadbent commented Oct 17, 2026 •

Copy link
Copy Markdown
Member

Second of twelve stacked PRs for 0.2.0.

What this fixes

  • Every line logged in a Sidekiq job was written twice (Sidekiq log entries are emitted twice #13). Sidekiq's Rails integration broadcasts Rails.logger to Sidekiq.logger, and both write to the same SemanticLogger appenders. broadcast_to now ignores SemanticLogger loggers.
  • Successful jobs could be marked as failed (Sidekiq logger logs the live Sidekiq::Context hash, which can mark successful jobs as failed #14). The logger put the live Sidekiq::Context hash into each entry, and SemanticLogger formats on its own thread, so Sidekiq adding :elapsed raised "can't add a new key into hash during iteration". It now logs a copy.
  • Lines logged during a job have the job's jid and class in ctx, so you can pull every line for one job run out of the logs. A Hash logged with its own ctx is merged with the job's.
  • Breaking: a logged Hash is written with its keys at the top level of the line instead of under payload. A Hash can set its own src and evt; ts and lvl are reserved, so they're reported as an error and dropped.
  • A failed Sidekiq job is one structured warn line with its jid, class, queue and retry count, instead of Sidekiq's default handler's three text lines with the job's arguments in a JSON string. ActiveJob jobs' failures are left to the ActiveJob integration.

Addresses #13 and #14.

Testing

Every regression test fails without its fix. Sorbet and the unit suite (293 tests) pass at this branch's tip.


Stack for 0.2.0, merged in order: #16 → #17 → #18 → #19 → #20 → #21 → #22 → #23 → #24 → #25 → #26 → #27

In a Sidekiq server process, Sidekiq's Rails integration calls
Rails.logger.broadcast_to(Sidekiq.logger) after initialization.
LogStruct's logger re-sent every String message to its broadcasts, and
both loggers write to the same SemanticLogger appenders, so each
Rails.logger call inside a job was written twice: once as an app line
and once as a Sidekiq line. broadcast_to now ignores SemanticLogger
loggers.

Fixes #13
The Sidekiq logger put the live Sidekiq::Context hash into each log
struct. SemanticLogger formats on its appender thread, so for a fast job
it could still be iterating that hash when Sidekiq's JobLogger added
:elapsed after the job finished. The resulting "can't add a new key into
hash during iteration" error was raised after the job had succeeded, so
Sidekiq marked it as failed and retried it.

Fixes #14
Sidekiq's own log lines carry the job ID and class in ctx, but lines the
job itself writes with Rails.logger don't, so there was no way to pull
every line for one job run out of the logs. Until the broadcast fix,
the duplicate Sidekiq copy of each line was the only one with a job ID.

A Sidekiq server middleware, first in the chain, now pushes the job's
jid and class as SemanticLogger named tags for the job's duration, and
the formatter writes them to ctx unless the line already has one.
ActiveJob jobs show their own class rather than the Sidekiq wrapper,
matching Sidekiq's context.
The logger passed a Hash to SemanticLogger as `payload: hash`, which
SemanticLogger stores as {payload: hash}, so Rails.logger.info(src:
"rails", evt: "rate_limit", ...) was written as
{"payload":{"src":"rails",...},"src":"app","evt":"log"}. Fields that
log searches and metric filters expect at the top level were nested
under "payload", and the line's own src and evt were overridden. Hashes
are now passed as the payload itself; structs are unchanged.

A logged Hash may set its own src and evt. Its ts and lvl are reported
as LogStruct errors and skipped, since the line's timestamp and level
come from the logger. During a Sidekiq job, a Hash's own ctx keeps its
keys and gains the job's jid and class.
Sidekiq's default error handler logged three warn lines for each failed
job: the job hash as a JSON string inside msg (with the job's
arguments, which LogStruct's filters can't reach there), the error, and
the backtrace. LogStruct replaces it with one structured line (src
sidekiq, evt error) with the error class, message, backtrace, jid, job
class, queue and retry count, and no arguments. ActiveJob jobs' errors
are left to the ActiveJob integration, which already logs them. Error
handlers the app added stay.
@coderabbitai

coderabbitai Bot commented Oct 17, 2026 •

Copy link
Copy Markdown

Warning

Review limit reached

  • Run on-demand review

This review includes 9 billable files and costs up to $2.25.

  • Ask an admin to make reviews automatic

Open in CodeRabbit

Reviews can continue after your included limit without a manual trigger. An admin must approve usage-based billing.

Or wait 38 minutes for your next included review.

Check out review usage here.

View limit details

Limit details: You’ve used all 2 included reviews currently available. Your 53 included PR review attempts over the past 7 days set your current allowance at 2 reviews per hour.

Learn how review limits work.

Review configuration:

⚙️ Run configuration
  • Configuration used: Organization UI
  • Review profile: CHILL
  • Plan: Essentials
  • Run ID: 6ebd8082-10ed-4359-9b3c-9823a3efe428
📥 Commits

Reviewing files that changed from the base of the PR and between 641cc46 and 9bcab46.

📒 Files selected for processing: 9
  • docs/lib/integration-helpers.ts
  • lib/log_struct/integrations/sidekiq.rb
  • lib/log_struct/integrations/sidekiq/job_context_middleware.rb
  • lib/log_struct/integrations/sidekiq/logger.rb
  • lib/log_struct/semantic_logger/concerns/log_methods.rb
  • lib/log_struct/semantic_logger/formatter.rb
  • lib/log_struct/semantic_logger/logger.rb
  • test/log_struct/integrations/sidekiq_test.rb
  • test/log_struct/semantic_logger_test.rb
  • Autofix · Keep fixing CodeRabbit findings and required CI, and resolving merge conflicts

Comment @coderabbitai help to get the list of available commands.

@ndbroadbent
ndbroadbent deleted the branch nathan/filtering-security-fixes October 17, 2026 23:10
@ndbroadbent ndbroadbent reopened this Oct 17, 2026
@ndbroadbent
ndbroadbent changed the base branch from nathan/filtering-security-fixes to main October 17, 2026 23:12
@ndbroadbent
ndbroadbent merged commit 3bfe669 into main Oct 17, 2026
1 check passed
@ndbroadbent
ndbroadbent deleted the nathan/sidekiq-fixes branch October 17, 2026 23:12
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant